 /*******************************************************************************
  * Copyright (c) 2005, 2006 IBM Corporation and others.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
  * http://www.eclipse.org/legal/epl-v10.html
  *
  * Contributors:
  * IBM Corporation - initial API and implementation
  *******************************************************************************/

 package org.eclipse.osgi.internal.profile;

 import java.io.*;
 import java.util.*;
 import org.eclipse.osgi.framework.debug.FrameworkDebugOptions;
 import org.eclipse.osgi.framework.internal.core.FrameworkProperties;

 public class DefaultProfileLogger implements ProfileLogger {
     protected static final String DEFAULTPROFILE_PROP = "osgi.defaultprofile."; //$NON-NLS-1$
 protected static final String PROP_FILENAME = DEFAULTPROFILE_PROP + "logfilename"; //$NON-NLS-1$
 protected static final String PROP_LOGSYNCHRONOUSLY = DEFAULTPROFILE_PROP + "logsynchronously"; //$NON-NLS-1$
 protected static final String PROP_BUFFERSIZE = DEFAULTPROFILE_PROP + "buffersize"; //$NON-NLS-1$

     protected static final String DEFAULTPROFILE_OPTION = "org.eclipse.osgi/defaultprofile/"; //$NON-NLS-1$
 protected static final String OPTION_FILENAME = DEFAULTPROFILE_OPTION + "logfilename"; //$NON-NLS-1$
 protected static final String OPTION_LOGSYNCHRONOUSLY = DEFAULTPROFILE_OPTION + "logsynchronously"; //$NON-NLS-1$
 protected static final String OPTION_BUFFERSIZE = DEFAULTPROFILE_OPTION + "buffersize"; //$NON-NLS-1$

     protected boolean logSynchronously = false;
     protected long startTime = 0;
     protected static final int DEFAULT_BUFFER_SIZE = 256;

     protected TimeEntry[] timeLogEntries = null;
     protected int timeEntriesIndex = 0;
     protected StringBuffer timelog = null;

     protected long launchTime = -1;
     protected int bufferSize = DEFAULT_BUFFER_SIZE;
     protected String logFileName = null;
     protected File logFile = null;
     private StringBuffer entryReport = new StringBuffer (120);
     private StringBuffer padsb = new StringBuffer (16); // to prevent creating this over and over
 protected int indent;
     protected int timePaddingLength;
     protected Stack scopeStack;
     protected Map scopeToAccumPerfDataMap;

     public DefaultProfileLogger() {
         initProps();

         int size = getBufferSize();
         timeLogEntries = new TimeEntry[size];
         timelog = new StringBuffer (4096);
         for (int i = 0; i < size; i++) {
             timeLogEntries[i] = timeEntryFactory();
         }
         timeEntriesIndex = 0;

         launchTime = getLaunchTime();
         if (launchTime == -1) {
             startTime = getMainStartTime();
         } else {
             startTime = launchTime;
         }

         long freq = getTimerFrequency();
         for (timePaddingLength = 3; freq > 9; timePaddingLength++) {
             freq /= 10;
         }

         logInitMessages();
     }

     protected void logInitMessages() {
         int index = 0;
         if (launchTime != -1L) {
             logTime(Profile.FLAG_NONE, "DefaultProfileLogger.init()", "launch time initialized", null); //$NON-NLS-1$//$NON-NLS-2$
 timeLogEntries[index++].time = launchTime;
         }

         logTime(Profile.FLAG_NONE, "DefaultProfileLogger.init()", "start time initialized", null); //$NON-NLS-1$//$NON-NLS-2$
 timeLogEntries[index++].time = getMainStartTime();
     }

     protected long getLaunchTime() {
         String launchTimeString = FrameworkProperties.getProperty("launch.startMillis"); //$NON-NLS-1$
 if (launchTimeString != null) {
             return Long.parseLong(launchTimeString);
         }
         return -1L;
     }

     protected long getMainStartTime() {
         String timeString = FrameworkProperties.getProperty("eclipse.startTime"); //$NON-NLS-1$
 if (timeString != null)
             return Long.parseLong(timeString);

         return System.currentTimeMillis();
     }

     public void initProps() {
         String prop;
         FrameworkDebugOptions dbgOptions = null;
         // if osgi.debug is not available, don't force DebugOptions
 // to init as this variable may be set later on where
 // DebugOptions will succeed.
 if (FrameworkProperties.getProperty("osgi.debug") != null) { //$NON-NLS-1$
 dbgOptions = FrameworkDebugOptions.getDefault();
             if (dbgOptions != null) {
                 logFileName = dbgOptions.getOption(OPTION_FILENAME);
                 logSynchronously = dbgOptions.getBooleanOption(OPTION_LOGSYNCHRONOUSLY, false);
                 int size = dbgOptions.getIntegerOption(OPTION_BUFFERSIZE, 0);
                 if (size > 0)
                     bufferSize = size;
             }
         }

         if ((prop = FrameworkProperties.getProperty(PROP_FILENAME)) != null) {
             logFileName = prop;
             if (dbgOptions != null)
                 dbgOptions.setOption(OPTION_FILENAME, logFileName);
         }
         if ((prop = FrameworkProperties.getProperty(PROP_LOGSYNCHRONOUSLY)) != null) {
             logSynchronously = Boolean.valueOf(prop).booleanValue();
             if (dbgOptions != null)
                 dbgOptions.setOption(OPTION_LOGSYNCHRONOUSLY, new Boolean (logSynchronously).toString());
         }
         if ((prop = FrameworkProperties.getProperty(PROP_BUFFERSIZE)) != null) {
             try {
                 int value = Integer.parseInt(prop);
                 if (value > 0) {
                     bufferSize = value;
                     if (dbgOptions != null)
                         dbgOptions.setOption(OPTION_BUFFERSIZE, Integer.toString(bufferSize));
                 }
             } catch (NumberFormatException e) {
                 // do nothing
 }
         }
     }

     public synchronized void logTime(int flag, String id, String msg, String description) {
         if (timeEntriesIndex == timeLogEntries.length) {
             makeLog();
             logTime(Profile.FLAG_NONE, "Profile.logTime()", "log entries rolled", null); //$NON-NLS-1$ //$NON-NLS-2$
 }

         TimeEntry entry = timeLogEntries[timeEntriesIndex++];
         entry.time = getTime();
         entry.id = id;
         entry.msg = msg;
         entry.flag = flag;
         entry.description = description;

         if (logSynchronously) {
             System.out.print(getProfileLog().substring(2));
         }
     }

     public synchronized String getProfileLog() {
         String log;
         log = getProfileLogReport();
         writeToProfileLogFile(log);
         return log;
     }

     public synchronized void accumLogEnter(String scope) {
         // Initialize our data structures
 if (scopeStack == null)
             scopeStack = new Stack();
         if (scopeToAccumPerfDataMap == null)
             scopeToAccumPerfDataMap = new TreeMap();

         // We want getTime() to evaluate as late as possible
 scopeStack.push(new AccumPerfScope(scope, getTime()));
     }

     public synchronized void accumLogExit(String scope) {
         // What time is it?
 long exit = getTime();

         // Initialize our data structures
 if (scopeStack == null)
             scopeStack = new Stack();
         if (scopeToAccumPerfDataMap == null)
             scopeToAccumPerfDataMap = new TreeMap();

         // Do our calculations
 AccumPerfScope then = (AccumPerfScope) scopeStack.pop();
         if (then == null)
             System.err.println("ACCUM PERF ERROR: Scope stack empty: " + scope); //$NON-NLS-1$
 else {
             if (!then.scope.equals(scope))
                 System.err.println("ACCUM PERF ERROR: Scope mismatch: then='" + then.scope + "', now='" + scope + "'"); //$NON-NLS-1$//$NON-NLS-2$//$NON-NLS-3$

             AccumPerfData now = (AccumPerfData) scopeToAccumPerfDataMap.get(scope);
             if (now == null) {
                 now = new AccumPerfData(scope);
                 scopeToAccumPerfDataMap.put(scope, now);
             }

             now.time += exit - then.enter;
             now.enters++;
         }
     }

     protected long getTime() {
         return System.currentTimeMillis();
     }

     protected long getTimerFrequency() {
         return 1000L; // millisecond
 }

     protected TimeEntry findCompareEntry(int index, String id, int flag) {
         if (index > 0)
             index--;
         int prev = index;
         if (flag != Profile.FLAG_ENTER) {
             while (index >= 0) {
                 TimeEntry entry = timeLogEntries[index];
                 if (entry.id.equals(id)) {
                     switch (flag) {
                         case Profile.FLAG_NONE :
                             return entry;
                         case Profile.FLAG_EXIT :
                             if (entry.flag == Profile.FLAG_ENTER)
                                 return entry;
                             break;
                     }
                 }
                 index--;
             }
         }
         return timeLogEntries[prev];
     }

     protected String entryReport(TimeEntry entry, TimeEntry compareWith) {
         // indent level:
 entryReport.setLength(0);
         if (entry.flag == Profile.FLAG_ENTER)
             indent++;
         long zeroTime = getRelativeTime(getStartTime());

         entryReport.append('-');
         long entryTime = getRelativeTime(entry.time);
         long diff = entryTime - zeroTime;
         entryReport.append(pad(Long.toString(diff), timePaddingLength));
         entryReport.append(" :"); //$NON-NLS-1$
 diff = entry.time - compareWith.time;
         entryReport.append(pad(Long.toString(diff), timePaddingLength));
         entryReport.append(pad("", indent * 2)); // indent before displaying the entry.id //$NON-NLS-1$

         if (entry.flag == Profile.FLAG_ENTER)
             entryReport.append(" >> "); //$NON-NLS-1$
 else if (entry.flag == Profile.FLAG_EXIT)
             entryReport.append(" << "); //$NON-NLS-1$
 else if (entry.flag == Profile.FLAG_NONE)
             entryReport.append(" -- "); //$NON-NLS-1$

         entryReport.append(entry.id);
         entryReport.append(" > "); //$NON-NLS-1$
 entryReport.append(entry.msg);
         if (entry.description != null) {
             entryReport.append(" :: "); //$NON-NLS-1$
 entryReport.append(entry.description);
         }
         entryReport.append("\r\n"); //$NON-NLS-1$

         if (entry.flag == Profile.FLAG_EXIT)
             indent -= 1;
         return entryReport.toString();
     }

     protected String accumEntryReport(AccumPerfData d) {
         return (" " + d.scope + ":enters=" + d.enters + ";time=" + d.time + ";\r\n"); //$NON-NLS-1$//$NON-NLS-2$//$NON-NLS-3$//$NON-NLS-4$
 }

     protected void makeLog() {
         indent = 0;
         timelog.append("\r\n"); //$NON-NLS-1$
 for (int i = 0; i < timeEntriesIndex; i++) {
             TimeEntry entry = timeLogEntries[i];
             TimeEntry cmpEntry = findCompareEntry(i, entry.id, entry.flag);
             timelog.append(entryReport(entry, cmpEntry));
         }
         timeEntriesIndex = 0;

         if (scopeToAccumPerfDataMap == null || scopeToAccumPerfDataMap.isEmpty())
             return; // No data; nothing to do
 timelog.append("\r\n"); //$NON-NLS-1$
 timelog.append("Cumulative Log:\r\n"); //$NON-NLS-1$
 Iterator iter = scopeToAccumPerfDataMap.values().iterator();
         while (iter.hasNext()) {
             AccumPerfData d = (AccumPerfData) iter.next();
             timelog.append(accumEntryReport(d));
         }
         scopeToAccumPerfDataMap.clear();
     }

     protected String pad(String str, int size) {
         padsb.setLength(0);
         int len = str.length();
         int count = size - len;
         for (int i = 0; i < count; i++)
             padsb.append(' ');
         padsb.append(str);
         return padsb.toString();
     }

     protected String getProfileLogReport() {
         if (timelog == null)
             return ""; //$NON-NLS-1$
 makeLog();
         String log = timelog.toString();
         timelog.setLength(0);
         return log;
     }

     protected void writeToProfileLogFile(String log) {
         File profileLog = getProfileLogFile();
         if (profileLog == null)
             return;
         FileWriter fw = null;
         try {
             fw = new FileWriter(profileLog.getAbsolutePath(), true);
             fw.write(log);
         } catch (IOException e) {
             e.printStackTrace();
         } finally {
             if (fw != null)
                 try {
                     fw.close();
                 } catch (IOException e) {
                     // do nothing
 }
         }
     }

     protected File getProfileLogFile() {
         if (logFile == null)
             if ((logFileName != null) && (logFileName.length() > 0))
                 logFile = new File(logFileName);
         return logFile;
     }

     protected long getStartTime() {
         return startTime;
     }

     protected long getRelativeTime(long absoluteTime) {
         return absoluteTime;
     }

     protected int getBufferSize() {
         if (bufferSize < 2)
             return DEFAULT_BUFFER_SIZE;
         return bufferSize;
     }

     protected TimeEntry timeEntryFactory() {
         return new TimeEntry();
     }

     protected class TimeEntry {
         public long time;
         public String id;
         public String msg;
         public String description;
         public int flag;
     }

     protected static class AccumPerfData {
         public AccumPerfData(String scope) {
             this.scope = scope;
         }

         public String scope;
         public long time;
         public long enters;
     }

     protected static class AccumPerfScope {
         public AccumPerfScope(String scope, long enter) {
             this.scope = scope;
             this.enter = enter;
         }

         public String scope;
         public long enter;
     }
 }

